Skip to content

Stop test-harness artefacts from losing LAVA results - #554

Open
Ricardo Salveti (ricardosalveti) wants to merge 5 commits into
qualcomm-linux:mainfrom
ricardosalveti:claude-findings
Open

Stop test-harness artefacts from losing LAVA results#554
Ricardo Salveti (ricardosalveti) wants to merge 5 commits into
qualcomm-linux:mainfrom
ricardosalveti:claude-findings

Conversation

@ricardosalveti

@ricardosalveti Ricardo Salveti (ricardosalveti) commented Aug 27, 2026

Copy link
Copy Markdown
Contributor

Analysis of all 12,658 meta-qcom LAVA jobs run between 19 and 27 Aug 2026
found that a large share of the red in CI is produced by the harness rather
than by the platforms under test: 62 of 287 recorded test-case failures had
no RESULT=FAIL in the log at all, and 616 jobs died without reporting any
result. This series fixes the six causes that are ours to fix.

  • send-to-lava: kernel printk splices into testcase signals because the
    quiet window closes before the line has left the UART. 36 of 200 sampled
    jobs were affected; cdsp_remoteproc lost 15 of its 51 failures this way.
  • lib_display: DRM hot-plug detection is sampled once, so boards that do
    have a panel skip 18-21% of the time (hamoa-iot-evk-04, lemans-hyd-01).
  • remoteproc: the boot check reads a snapshot taken moments after login,
    failing instances that are still coming up (cdsp1 on sa8775p, 9-21%).
  • AudioRecord: the capture watchdog does not allow for PipeWire start-up,
    truncating recordings below the duration gate.

Each commit carries the measured failure rates it addresses. No test verdicts
change: every fix either lets a passing test be read, or makes a failing test
report as a failure instead of taking the job down with it.

All touched scripts pass shellcheck and sh -n.

@ricardosalveti

Copy link
Copy Markdown
Contributor Author

This is the outcome of an investigation of all the lava jobs executed over the past 8 days.

Comment thread Runner/utils/lib_display.sh Outdated
Comment thread Runner/utils/send-to-lava.sh Outdated
done < "$SIGNAL_FILE"
done

drain_kernel_console

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LAVA_SIGNAL_DRAIN_SECONDS is a fixed 0.3 seconds for the entire result file, but this loop can emit an arbitrary number of signals. On a slow UART, a sufficiently large result file takes longer than 0.3 seconds to serialize, so printk can be restored while the final signal is still on the wire the corruption this change is intended to prevent.

IMO, it is good to keep the quiet window proportional to the emitted byte count/console speed, or drain per signal, and do not restore printk until the complete buffered emission has cleared. Any thoughts?

dwc_waited=0

while :; do
DISPLAY_CONNECTED_SUMMARY="$(display_connected_summary 2>/dev/null || true)"

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This polls for the full 20 seconds even when DRM was never probed: display_connected_summary returns none when /sys/class/drm is absent. Every display-suite consumer then pays that delay before the same skip, multiplying CI cost on headless or failed-driver targets.

Detect the absent DRM directory or absence of any connector nodes before entering the retry loop and return the existing clean skip immediately, reserve polling for an existing connector that is temporarily reported disconnected.

#
# rstate is a snapshot taken moments after login; give a processor still
# coming up BOOT_TO seconds to reach running before failing it.
if [ "$rstate" != "running" ] && [ "$BOOT_TO" -gt 0 ] 2>/dev/null; then

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[This is for maintainability] The boot-state wait, its BOOT_TO parsing, and its result refresh are duplicated across all four remoteproc suites. Please move the common “wait for initial running state, then return the refreshed state” behavior into functestlib.sh, leaving each suite responsible only for its processor-specific policy and result reporting. That keeps future timeout, diagnostics, and validation changes consistent across ADSP/CDSP/GPDSP/WPSS.

The script quiets printk around each signal printf, but printf returns
once the line is in the tty buffer, not once the UART has sent it, so
printk resumes while the signal is still on the wire and can split it:

  <<<LAVA_SIGNAL_TESTCASE TEST_CASE_ID=cdsp_remoteproc RESU[   69.2]

LAVA cannot parse that, so a passing test is recorded as a failure.
Over 12658 jobs run between 19 and 27 Aug 2026, 62 of 287 recorded
test-case failures had no RESULT=FAIL in the log at all, and 36 of 200
sampled jobs carried a spliced signal.

Quiet printk across the whole emission instead, sleeping before the
first signal and after each one (LAVA_SIGNAL_DRAIN_SECONDS, default
0.3s) so queued kernel output finishes first and printk only resumes
once the last signal has cleared the link, however many lines the
result file holds. The drain is skipped when printk could not be
quieted, the value is validated where it is defaulted, and the signals
are read into memory up front so the INT/TERM trap deleting the signal
file cannot suppress them.

Assisted-by: Claude Code:claude-opus-5
Signed-off-by: Ricardo Salveti <ricardo.salveti@oss.qualcomm.com>
display_connected_summary() warns via log_warn when /sys/class/drm is
missing, and log() writes to stdout, which callers capture as the
summary: a board whose display driver never probed reads as having a
connected panel, because "[WARN] ..." is neither empty nor "none".
Send the warning to stderr.

Assisted-by: Claude Code:claude-fable-5
Signed-off-by: Ricardo Salveti <ricardo.salveti@oss.qualcomm.com>
display_log_snapshot_and_require_connector() samples /sys/class/drm
once, but hot-plug detection is asynchronous, so a board with a panel
can still read disconnected seconds after boot. Between 19 and 27 Aug
2026 boards tagged display skipped at rates only a race explains:
hamoa-iot-evk-04 42 of 196 runs, lemans-hyd-01 36 of 197, and every
skip is silent.

Poll instead, bounded by DISPLAY_CONNECTOR_WAIT (default 20s) every
DISPLAY_CONNECTOR_POLL (2s), on the monotonic clock so an NTP step
cannot cut the wait short. Connector nodes are created at driver bind,
not by hot-plug, so when none exists the gate skips immediately;
boards with a connector and nothing attached reach the same skip, only
later.

Assisted-by: Claude Code:claude-opus-5
Signed-off-by: Ricardo Salveti <ricardo.salveti@oss.qualcomm.com>
The boot check compares a state snapshot taken moments after login
against running, so an instance still coming up is recorded as a
failure; on lemans-evk the second CDSP loses that race. Between 19 and
27 Aug 2026 cdsp_remoteproc failed this way on every board with more
than one instance (kaanapali-mtp-06 8 of 17, lemans-02 9 of 89), at
rates that rule out a processor that never boots.

Add wait_remoteproc_boot_state() to functestlib.sh: re-read the state,
give a processor not yet running a bounded wait, and return the
refreshed state. All four suites call it with BOOT_TO/--boot-to
(default 30s, 0 restores the single shot), keeping the boot-wait
policy in one place. The wait runs on get_monotonic_seconds() so an
NTP step cannot cut it short, and a non-numeric BOOT_TO falls back to
the default instead of silently disabling the wait.

Assisted-by: Claude Code:claude-opus-5
Signed-off-by: Ricardo Salveti <ricardo.salveti@oss.qualcomm.com>
pw-record has no duration flag on this path, so the recording is ended
by the external watchdog, whose clock starts before PipeWire has opened
the device: whatever the graph spends coming up is taken out of the
recording, and a slow start fails the duration check
(duration-too-short:0.724<3.500). Between 19 and 27 Aug 2026 this cost
iq-x7181-evk 19 to 29 failures per AudioRecord config out of ~207 runs.

Run the watchdog for the requested duration plus
AUDIO_RECORD_START_GRACE (default 5s) so a slow start eats the headroom
instead of the recording. The duration validated against is unchanged
and an explicit --timeout still overrides the watchdog.

Assisted-by: Claude Code:claude-opus-5
Signed-off-by: Ricardo Salveti <ricardo.salveti@oss.qualcomm.com>
while [ "$i" -le "$LOOPS" ]; do
iso="$(date -u +%Y-%m-%dT%H:%M:%SZ)"
effective_timeout="$secs"
effective_timeout="$(audio_record_timeout_with_grace "$secs")"

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Keep startup headroom separate from requested recording duration. For PipeWire and PulseAudio, the watchdog is what stops the recorder, so this changes every fast-start capture from RECORD_SECONDS to RECORD_SECONDS + AUDIO_RECORD_START_GRACE. A ten-case matrix adds 50 seconds per loop by default and produces longer artifacts than requested. Apply the grace only while waiting for the recorder to become active, then start the requested-duration timer, rather than extending the whole capture watchdog.

# 0 when at least one connected display is found
# 1 when the wait expired with no connected display
display_wait_for_connector() {
dwc_wait="${DISPLAY_CONNECTOR_WAIT:-20}"

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Avoid charging the full connector wait to every optional-display skip. display_log_snapshot_and_require_connector() is used by many graphics and Weston suites. A target with DRM connector nodes but no connected panel now waits 20 seconds before each suite skips, turning one expected absence into a large CI penalty. Keep boot-settle handling bounded at orchestration level, or make the wait opt-in for the initial display probe while later suites retain an immediate no-display skip.

printf '\n%s\n\n' "$signal_line"
restore_kernel_console
done < "$SIGNAL_FILE"
drain_kernel_console

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The per-signal drain is redundant while printk remains quiet for the whole loop. The console is muted from line 203 through line 213, so draining after every testcase adds LAVA_SIGNAL_DRAIN_SECONDS for each result without additional protection. A 50-case result file adds 15 seconds by default. Drain once before the first signal and once after the final signal while retaining the quiet window across the complete emission.

esac
}

# Add startup headroom to the capture watchdog.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

audio_record_timeout_with_grace() is reusable audio timeout policy and is called from both record execution paths.
Move it to the shared audio library next to the timeout/recording helpers, then have this runner only select the requested duration and invoke the helper. This keeps timeout semantics testable and prevents future audio suites from copying policy into their own run.sh.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants